extensionSystem: Add debug logging

Now that we can use console.debug() to log messages that aren't
shown by default, we can be a lot more verbose without spamming
the system log.

Use that to all extension state changes, which can be useful for
debugging.

Part-of: <https://gitlab.gnome.org/GNOME/gnome-shell/-/merge_requests/3058>

diff --git a/js/ui/extensionSystem.js b/js/ui/extensionSystem.js
index a03d0f10f2f5c696363545fcd0fea07252195e63..ca6c9180d024c2b00421536cd56670dc680ba485 100644 (file)
--- a/js/ui/extensionSystem.js
+++ b/js/ui/extensionSystem.js
@@ -21,6 +21,10 @@ const EXTENSION_DISABLE_VERSION_CHECK_KEY = 'disable-extension-version-validatio
 
 const UPDATE_CHECK_TIMEOUT = 24 * 60 * 60; // 1 day in seconds
 
+function stateToString(state) {
+    return Object.keys(ExtensionState).find(k => ExtensionState[k] === state);
+}
+
 export class ExtensionManager extends Signals.EventEmitter {
     constructor() {
         super();
@@ -150,6 +154,14 @@ export class ExtensionManager extends Signals.EventEmitter {
         delete extension.stylesheet;
     }
 
+    _changeExtensionState(extension, newState) {
+        const strState = stateToString(newState);
+        console.debug(`Changing state of extension ${extension.uuid} to ${strState}`);
+
+        extension.state = newState;
+        this.emit('extension-state-changed', extension);
+    }
+
     _extensionSupportsSessionMode(uuid) {
         const extension = this.lookup(uuid);
 
@@ -173,8 +185,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         if (extension.state !== ExtensionState.ENABLED)
             return;
 
-        extension.state = ExtensionState.DISABLING;
-        this.emit('extension-state-changed', extension);
+        this._changeExtensionState(extension, ExtensionState.DISABLING);
 
         // "Rebase" the extension order by disabling and then enabling extensions
         // in order to help prevent conflicts.
@@ -191,6 +202,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         for (let i = 0; i < orderReversed.length; i++) {
             let otherUuid = orderReversed[i];
             try {
+                console.debug(`Temporarily disable extension ${otherUuid}`);
                 this.lookup(otherUuid).stateObj.disable();
             } catch (e) {
                 this.logExtensionError(otherUuid, e);
@@ -208,6 +220,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         for (let i = 0; i < order.length; i++) {
             let otherUuid = order[i];
             try {
+                console.debug(`Re-enable extension ${otherUuid}`);
                 // eslint-disable-next-line no-await-in-loop
                 await this.lookup(otherUuid).stateObj.enable();
             } catch (e) {
@@ -217,10 +230,8 @@ export class ExtensionManager extends Signals.EventEmitter {
 
         this._extensionOrder.splice(orderIdx, 1);
 
-        if (extension.state !== ExtensionState.ERROR) {
-            extension.state = ExtensionState.DISABLED;
-            this.emit('extension-state-changed', extension);
-        }
+        if (extension.state !== ExtensionState.ERROR)
+            this._changeExtensionState(extension, ExtensionState.DISABLED);
     }
 
     async _callExtensionEnable(uuid) {
@@ -238,8 +249,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         if (extension.state !== ExtensionState.DISABLED)
             return;
 
-        extension.state = ExtensionState.ENABLING;
-        this.emit('extension-state-changed', extension);
+        this._changeExtensionState(extension, ExtensionState.ENABLING);
 
         try {
             this._loadExtensionStylesheet(extension);
@@ -250,9 +260,8 @@ export class ExtensionManager extends Signals.EventEmitter {
 
         try {
             await extension.stateObj.enable();
-            extension.state = ExtensionState.ENABLED;
+            this._changeExtensionState(extension, ExtensionState.ENABLED);
             this._extensionOrder.push(uuid);
-            this.emit('extension-state-changed', extension);
         } catch (e) {
             this._unloadExtensionStylesheet(extension);
             this.logExtensionError(uuid, e);
@@ -353,6 +362,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         const message = error instanceof Error
             ? error.message : error.toString();
 
+        console.debug(`Changing state of extension ${uuid} to ERROR`);
         extension.error = message;
         extension.state = ExtensionState.ERROR;
         if (!extension.errors)
@@ -442,30 +452,33 @@ export class ExtensionManager extends Signals.EventEmitter {
     }
 
     async loadExtension(extension) {
+        const {uuid} = extension;
+        console.debug(`Loading extension ${uuid}`);
         // Default to error, we set success as the last step
         extension.state = ExtensionState.ERROR;
 
         if (this._checkVersion && this._isOutOfDate(extension)) {
             extension.state = ExtensionState.OUT_OF_DATE;
         } else if (!this._canLoad(extension)) {
-            this.logExtensionError(extension.uuid, new Error(
+            this.logExtensionError(uuid, new Error(
                 'A different version was loaded previously. You need to log out for changes to take effect.'));
         } else {
-            let enabled = this._enabledExtensions.includes(extension.uuid) &&
-                          this._extensionSupportsSessionMode(extension.uuid);
+            const enabled = this._enabledExtensions.includes(uuid) &&
+                            this._extensionSupportsSessionMode(uuid);
             if (enabled) {
-                if (!await this._callExtensionInit(extension.uuid))
+                if (!await this._callExtensionInit(uuid))
                     return;
 
                 if (extension.state === ExtensionState.DISABLED)
-                    await this._callExtensionEnable(extension.uuid);
+                    await this._callExtensionEnable(uuid);
             } else {
                 extension.state = ExtensionState.INITIALIZED;
             }
 
-            this._unloadedExtensions.delete(extension.uuid);
+            this._unloadedExtensions.delete(uuid);
         }
 
+        console.debug(`Extension ${uuid} in state ${stateToString(extension.state)} after loading`);
         this._updateCanChange(extension);
         this.emit('extension-state-changed', extension);
     }
@@ -478,8 +491,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         // broke too much.
         await this._callExtensionDisable(uuid);
 
-        extension.state = ExtensionState.UNINSTALLED;
-        this.emit('extension-state-changed', extension);
+        this._changeExtensionState(extension, ExtensionState.UNINSTALLED);
 
         // The extension is now cached and it's impossible to load a different version
         if (type === ExtensionType.PER_USER && extension.isImported)
@@ -548,8 +560,7 @@ export class ExtensionManager extends Signals.EventEmitter {
         }
 
         extension.stateObj = extensionState;
-        extension.state = ExtensionState.DISABLED;
-        this.emit('extension-loaded', uuid);
+        this._changeExtensionState(extension, ExtensionState.DISABLED);
         return true;
     }